Skip to content

watch: fix stale watcher state across log rotation - #6

Merged
bigbes merged 1 commit into
masterfrom
bigbes/tntp-3131-watch-lifecycle
Aug 10, 2026
Merged

watch: fix stale watcher state across log rotation#6
bigbes merged 1 commit into
masterfrom
bigbes/tntp-3131-watch-lifecycle

Conversation

@bigbes

@bigbes bigbes commented Aug 6, 2026

Copy link
Copy Markdown

Fixes the two test_log_rotate failure modes seen in tt CI after the v1.4.14 bump (first master run, 2/42 parametrizations, delay_time=0.01):

  • duplicated first line after rotation — a watch armed while the file was being replaced took its size baseline from the tailer's offset in the old file (fw.Size = pos). The first write to the new, smaller file then looked like a truncation, and the spurious reopen re-read the file from offset zero, re-delivering the lines already sent. A second path to the same symptom: the pendingReopen/Truncated branches kept tail.changes across reopen(); when the rename fired right after the arming, the kept subscription was already dead with a latched Deleted notification, which triggered a bogus second reopen.
  • tailer hangs, zero lines delivered — a watcher goroutine whose events channel was closed externally exited silently and removed the watch a second time, driving the shared refcount negative; the tailer blocked forever on a subscription that could not fire, and every later watch of the same name skipped the fsnotify subscription entirely.

The fix:

  • ChangeEvents seeds the size baseline (and the recorded inode) from a stat of the file at arm time. In-window changes are the recheck's job (that is what it is for); the watcher only needs a baseline consistent with the file it actually watches.
  • every reopen path (pendingDelete, pendingReopen, Truncated) drops the subscription via the new synchronous FileChanges.Stop() and re-arms it on the next EOF. The producer goroutine is stopped with a handshake before re-arming — an abandoned live producer would keep consuming from the shared per-file events channel, stealing events from the fresh subscription (this is why a bare tail.changes = nil would not be a safe fix).
  • a producer that finds its events channel closed reports the file as deleted instead of exiting silently, and removeWatch refuses to drive the refcount below zero.
  • pendingReopen is cleared when a pending delete performs the reopen, so a stale flag cannot cause one more reopen cycle later.

Regression tests (all reproduce on v1.4.14 on Linux, deterministically, via the existing delayBeforeWatch knob and the new delayBeforeRecheck knob; both inotify and polling watchers where applicable):

  • TestReplaceWhileArmingThenAppend, TestTruncateWhileArmingThenAppend — stale baseline → spurious truncation → duplication;
  • TestReplaceWhileRecheckingThenAppend — dead watch kept across pendingReopen → double reopen → duplication;
  • TestExternalWatchRemovalDoesNotHang — silent producer death → permanent hang;
  • TestRotationStressExactlyOnce — 20 rotations × 5 lines at 5 ms cadence, exactly-once delivery.

Verified: full suite with -race on Linux (docker, arm64) and macOS; new tests looped ×50 (stress) and ×8 (deterministic) plus ×10 under -race with zero flakes.

Part of TNTP-3131

The recheck added in v1.4.14 arms the watch first and inspects the
file afterwards, so a rotation can land on either side of the arming.
Both sides left the tailer with a watcher it must not trust:

* ChangeEvents seeded the watcher's size baseline with the caller's
  offset in the old file. When the name already pointed at the new,
  usually smaller file, the first write there looked like a truncation
  and the spurious reopen re-delivered every line already read from
  the new file. The baseline and the recorded inode now come from a
  stat of the file at arm time; changes that predate the watch are
  the recheck's job to find.

* The pendingReopen and Truncated paths kept tail.changes across a
  reopen. When the rename fired right after the arming, the kept
  subscription was already dead and carried a latched Deleted
  notification, which triggered a bogus second reopen re-delivering
  everything read in between. Every reopen path now drops the
  subscription and re-arms it on the next EOF, and the recheck picks
  up whatever happened in the gap. Dropping is safe now that
  FileChanges.Stop shuts the producer goroutine down synchronously;
  an abandoned live producer would keep stealing events from the
  shared per-file channel.

* A producer whose events channel was closed by an external
  RemoveWatch (e.g. Cleanup) exited silently and removed the watch a
  second time, driving the shared refcount negative: the tailer
  blocked forever, and every later watch of the same name skipped the
  fsnotify subscription and never got a single event. The producer
  now reports the file as deleted instead, and the tracker refuses to
  drive a refcount below zero.

A stale pendingReopen is also cleared when a pending delete performs
the reopen, so it cannot cause one more reopen cycle later. The new
delayBeforeRecheck test knob mirrors delayBeforeWatch and widens the
arm-to-recheck window for the regression tests.

Part of TNTP-3131
@bigbes
bigbes requested a review from Mockird31 August 7, 2026 04:27
bigbes added a commit to tarantool/tt that referenced this pull request Aug 7, 2026
go-tail v1.4.14 could deliver a line twice right after a log rotation:
a watch armed while the file was being replaced kept a stale size
baseline, so the first write to the new file looked like a truncation
and forced a reopen from offset zero; a watch kept across the reopen
paths could also be dead with a latched delete notification, forcing
one more reopen. A watcher goroutine that lost its events channel
exited silently, corrupting the shared watch refcount and stalling the
tailer forever.

The pinned revision is the head of tarantool/go-tail#6; switch it to
the v1.4.15 tag once the fix is released.

Part of TNTP-3131
@bigbes
bigbes merged commit fd5cc5a into master Aug 10, 2026
20 of 32 checks passed
@bigbes
bigbes deleted the bigbes/tntp-3131-watch-lifecycle branch August 10, 2026 05:37
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants